Profiling And StatisticsΒΆ

To help debugging and improving performances, you can enable Render Statistics and Render Profiling. The resulting stats and profile are output to the console log.

Enable Render Statistics and Profile

Select the Preferences, open the Rendering -> Logs & Diagnostics and check the Render Profile to enable profiling, and Render Statistics to enable logging statistics.

Render Profile

Render Profile provides insight on the performance of the rendering engine, and reports how functionalities take time during rendering. The profile is divided in 3 parts:

Profile

This reports the sections ordered by total time, as follow:

Profile
name                           | glob. |   time | clocks
Trace                          |  51.2 |  2m55s |  16.6T
SurfaceLighting                |  11.7 |  40.1s |  3.81T
EvalBsdfs                      |   7.7 |  26.3s |  2.50T
Texture                        |   5.7 |  19.5s |  1.86T
Bounce                         |   3.7 |  12.8s |  1.22T
RunShader                      |   2.9 |  9.90s |   941G
GeneratePrimary                |   2.5 |  8.48s |   806G
SampleVisibility               |   2.2 |  7.47s |   710G
ExecSurfaceShader              |   2.0 |  6.81s |   648G
Visibility                     |   1.8 |  6.32s |   601G
Contributions                  |   1.6 |  5.51s |   524G
MainLoop                       |   1.6 |  5.36s |   510G
Tessellate                     |   1.3 |  4.35s |   414G
Splatting                      |   1.1 |  3.63s |   346G
TextureLoadReadBitmap          |   0.9 |  3.13s |   298G
Transparent                    |   0.9 |  3.10s |   295G
Occlusion                      |   0.9 |  2.95s |   281G
VolumeLighting                 |   0.2 |  0.56s |  53.7G

This reads like Trace took 51.2% of the rendering time (2m55s, 16.6 Tera-clocks), while Texture lookups took 5.7% of the rendering time.

The various profile items are, listed by category:

  • Raytrace: all ray tracing related sections
    • Occlusion: the engine is evaluation shadowing (this may includes Opaque and Transparent)
    • Opaque: the engine is tracing opaque objects (this may includes Trace)
    • Transparent: the engine is tracing transparent objects (this may includes Trace)
    • Visibility: the engine is evaluation the visibility from camera and bounces (this may includes Opaque and Transparent)
    • Trace: the engine is tracing rays in the scene
    • Volume: the engine is tracing rays in volumetric objects
    • TraceCircles: the engine is tracing rays for SSS
  • Shading: all shading related sections
    • EvalBsdfs: inits and calls to the shading engine to evaluate surface properties
    • EvalAOVs: inits and calls to the shading engine to evaluate specific AOVs
    • ShadeVolumes: evaluate volume properties after Raytrace > Volume
    • ExecDisplacementShader: inits and calls to the displacement shader (this includes RunShader)
    • ExecSurfaceShader: inits and calls to the surface shader (this includes RunShader)
    • ExecVolumeShader: inits and calls to the volume shader (this includes RunShader)
    • RunShader: shader execution
    • Texture: Texture lookups
    • Voxel: Voxel grid lookups
    • GenerateProgram: shading program generation
    • CompileShader: JIT shader compilation
  • Integrator: all general path tracing sections
    • MainLoop: the path tracing base loop
    • GeneratePrimary: primary rays generation
    • SampleVisibility: opacity and volume sampling
    • VolumeLighting: volumetric direct light evaluation
    • SurfaceLighting: surface direct light evaluation
    • Contributions: writing into AOVs path buffers
    • Bounce: bounce rays generation
    • Splatting: writing into final frame buffers
  • Accelerator: all acceleration structures generation
    • BuildCurves: curves generation
    • BuildTriangles: triangles generation
    • Build2dTriangles: triangles generation for Bake2d
    • Tesselate: general shape generation
    • BuildScene: scene bvh generation
    • BuildScene2d: scene bvh generation for Bake2d
    • BuildBVH: bvh generation
  • Subdivision
    • CatmullClark: Catmull-Clark subdivision
    • Procedural: Guerilla procedural generation
    • DynamicLoad: RenderMan procedural generation
  • IO
    • ShapeLoad: shape loading from geometry archives
    • TextureLoad: generate texture loading
    • TextureLoadReadBitmap: bitmap loading

Profile by category

This reports the sections ordered by category, and by total time, as follow:

Profile by category
name                           | glob. |   time | clocks
Raytrace                       |  54.8 |   3m7s |  17.8T
  Trace                        |  51.2 |  2m55s |  16.6T
  Visibility                   |   1.8 |  6.32s |   601G
  Transparent                  |   0.9 |  3.10s |   295G
  Occlusion                    |   0.9 |  2.95s |   281G
Integrator                     |  24.5 |  1m23s |  7.97T
  SurfaceLighting              |  11.7 |  40.1s |  3.81T
  Bounce                       |   3.7 |  12.8s |  1.22T
  GeneratePrimary              |   2.5 |  8.48s |   806G
  SampleVisibility             |   2.2 |  7.47s |   710G
  Contributions                |   1.6 |  5.51s |   524G
  MainLoop                     |   1.6 |  5.36s |   510G
  Splatting                    |   1.1 |  3.63s |   346G
  VolumeLighting               |   0.2 |  0.56s |  53.7G
Shading                        |  18.3 |   1m2s |  5.97T
  EvalBsdfs                    |   7.7 |  26.3s |  2.50T
  Texture                      |   5.7 |  19.5s |  1.86T
  RunShader                    |   2.9 |  9.90s |   941G
  ExecSurfaceShader            |   2.0 |  6.81s |   648G
Accelerator                    |   1.4 |  4.62s |   440G
  Tessellate                   |   1.3 |  4.35s |   414G
IO                             |   0.9 |  3.25s |   309G
  TextureLoadReadBitmap        |   0.9 |  3.13s |   298G
Internal                       |   0.0 |  0.00s |      0

This profile is useful to get an rough idea of where the engine spend its activity, where usual profiles are evenly spent between Raytrace, Shading and Integrator. A strong deviation from this may indicate that something is problematic in the scene.

Profile by execution tree

This reports the sections organized as they appear directly during rendering, with the correct sections hierarchy.

Profile by execution tree
path                                     | local | total | glob. |   time | clocks
Root                                     |   0.0 | 100.0 |   0.0 |  0.00s |      0
.MainLoop                                |   1.6 |  98.6 |   1.6 |  5.36s |   510G
..Visibility                             |   1.8 |  27.8 |   1.8 |  6.32s |   601G
...Opaque                                |   0.0 |  24.9 |   0.0 |  0.12s |  11.7G
....Trace                                |  24.9 |  24.9 |  51.2 |  2m55s |  16.6T
...Transparent                           |   0.4 |   1.0 |   0.9 |  3.10s |   295G
....Trace                                |   0.6 |   0.7 |  51.2 |  2m55s |  16.6T
.....ExecSurfaceShader                   |   0.0 |   0.1 |   2.0 |  6.81s |   648G
......RunShader                          |   0.0 |   0.0 |   2.9 |  9.90s |   941G
..Occlusion                              |   0.9 |  27.1 |   0.9 |  2.95s |   281G
...Opaque                                |   0.0 |  25.2 |   0.0 |  0.12s |  11.7G
....Trace                                |  25.2 |  25.2 |  51.2 |  2m55s |  16.6T
...Transparent                           |   0.5 |   1.0 |   0.9 |  3.10s |   295G
....Trace                                |   0.5 |   0.5 |  51.2 |  2m55s |  16.6T
..EvalBsdfs                              |   7.7 |  19.2 |   7.7 |  26.3s |  2.50T
...ExecSurfaceShader                     |   2.0 |  11.5 |   2.0 |  6.81s |   648G
....RunShader                            |   2.9 |   9.5 |   2.9 |  9.90s |   941G
.....Texture                             |   5.7 |   6.6 |   5.7 |  19.5s |  1.86T
......TextureLoad                        |   0.0 |   0.9 |   0.0 |  0.00s |   426M
.......TextureLoadReadBitmap             |   0.9 |   0.9 |   0.9 |  3.13s |   298G
..SurfaceLighting                        |  11.7 |  11.7 |  11.7 |  40.1s |  3.81T
..Bounce                                 |   3.7 |   3.7 |   3.7 |  12.8s |  1.22T
..GeneratePrimary                        |   2.5 |   2.5 |   2.5 |  8.48s |   806G
..SampleVisibility                       |   2.2 |   2.2 |   2.2 |  7.47s |   710G
..Contributions                          |   1.6 |   1.6 |   1.6 |  5.51s |   524G
..Splatting                              |   1.1 |   1.1 |   1.1 |  3.63s |   346G
..VolumeLighting                         |   0.2 |   0.2 |   0.2 |  0.56s |  53.7G
..RunShader                              |   0.0 |   0.0 |   2.9 |  9.90s |   941G
.Tessellate                              |   1.3 |   1.3 |   1.3 |  4.35s |   414G

local represents the percentage of time spent at a particular point in the execution graph. total represents the percentage of time spent at a point with children included.

For instance, we can see in the above example, that, overall, Visibility accounts for 27.8% of the rendering time (with ray tracing included) but Trace accounts for 25.5% (24.9+0.6) of the time in Visibility.

Globally, Trace accounts for 51.2% of the rendering time.

Opacity usually reduces a lot performances as it forces the engine to pause raytracing and shade the opacity to keep tracing. This is notable in the profile below where Visibility and Occlusion account for 85% of the rendering time, most of it spend in Transparent tracing: 
Profile by execution tree
path                                     | local | total | glob. |   time | clocks
Root                                     |   0.0 | 100.0 |   0.0 |  0.00s |      0
.MainLoop                                |   0.7 | 100.0 |   0.7 |  0.44s |  39.5G
..Visibility                             |   4.7 |  43.0 |   4.7 |  3.19s |   282G
...Transparent                           |   0.1 |  38.3 |   0.3 |  0.22s |  20.1G
....Trace                                |  34.0 |  38.1 |  70.6 |  47.5s |  4.19T
.....ExecSurfaceShader                   |   1.7 |   4.1 |   4.6 |  3.11s |   276G
......RunShader                          |   2.4 |   2.4 |   6.7 |  4.51s |   399G
..Occlusion                              |   0.2 |  42.5 |   0.2 |  0.16s |  14.3G
...Transparent                           |   0.2 |  42.2 |   0.3 |  0.22s |  20.1G
....Trace                                |  36.5 |  42.0 |  70.6 |  47.5s |  4.19T
.....ExecSurfaceShader                   |   2.3 |   5.5 |   4.6 |  3.11s |   276G
......RunShader                          |   3.2 |   3.2 |   6.7 |  4.51s |   399G
..EvalBsdfs                              |   2.1 |   5.4 |   2.1 |  1.44s |   128G
...ExecSurfaceShader                     |   0.6 |   3.2 |   4.6 |  3.11s |   276G
....RunShader                            |   1.1 |   2.6 |   6.7 |  4.51s |   399G
.....Texture                             |   1.5 |   1.5 |   1.5 |  1.00s |  88.7G
..SurfaceLighting                        |   3.7 |   3.7 |   3.7 |  2.50s |   222G
..Bounce                                 |   1.3 |   1.3 |   1.3 |  0.87s |  76.8G
..SampleVisibility                       |   1.2 |   1.2 |   1.2 |  0.78s |  69.6G
..GeneratePrimary                        |   1.0 |   1.0 |   1.0 |  0.67s |  59.9G
..Contributions                          |   0.9 |   0.9 |   0.9 |  0.60s |  53.1G
..Splatting                              |   0.3 |   0.3 |   0.3 |  0.22s |  20.0G

Render Statistics

Statistics are displayed in the log, some before the actual rendering takes place (related to render settings and AOVs) and the rest at the end of rendering.

The most notable statistics are:

  • Accelerator:
    • generated triangles: the total number of generated triangles in the rendering
    • generated curves vertices: the total number of generated curve vertices in the rendering
    • generated geometry memory: the total amount of geometry memory allocated in the rendering
  • Attributes:
    • allocated materials: the total number of objects in the scene (accounting for instances)
  • Raycaster:
    • total rays: the total number of rays shot in the acceleration structures (note: opacity can double the number of rays)
  • Silver:
    • Primary rays: the number of primary rays.
    • Shadow rays/shading point: the average number of shadow rays per shading point (1)
    • Average samples/pixel: the average number of samples per pixel.
  • Texture:
    • still in cache: the amount of texture memory still kept in resource cache
    • total memory: the amount of texture memory that would have been needed if all textures were to be loaded
    • loaded memory: the amount of texture memory actually loaded. (2)
    • loaded tiles: the number of loaded texture tiles
    • unloaded tiles: the number of unloaded texture tiles
(1) This value is usually less than 5, and may indicate that too many lights are flagged as Separate Sampling. (2) Note that if this value is significantly larger than still in cache, this is probably due to the fact that the engine does not have enough memory to address and needed to purge textures repeatedly in order to fit in memory. In this case, unloaded tiles is in the same order of magnitude as loaded tiles. You can consider switching to Bucket rendering in the case the renderer does not have enough memory available.